fix: log worker crashes at warn level instead of debug - #2602
Open
luminalpark wants to merge 1 commit into
Open
Conversation
A worker script that dies after boot (non-zero exit status) currently logs the same debug-level "restarting" message as a clean FRANKENPHP_LOOP_MAX recycle. At the default log level a crash is therefore invisible: the in-flight request surfaces as an empty 500, the application never gets to log anything (the script died mid-request), and the exit status - the one datum needed to triage the death - is only available by running the whole server at debug level. Up to v1.2.x these terminations were logged at error level with the distinct message "unexpected termination, restarting" (see e.g. php#774, where that log line is how the reporter noticed the problem at all). This restores that message at warn level, matching the other worker-failure logs in tearDownWorkerScript, and keeps clean restarts at debug. Also aligns the guard of the watcher-enabled boot-failure log with the level it actually logs at (Enabled checked Error, LogAttrs wrote Warn).
dunglas
approved these changes
Aug 12, 2026
dunglas
left a comment
Member
There was a problem hiding this comment.
LGTM, but I wonder why we changed that behavior in the first time.
henderkes
reviewed
Aug 13, 2026
| if watcherIsEnabled { | ||
| // worker script has probably failed due to script changes while watcher is enabled | ||
| if globalLogger.Enabled(globalCtx, slog.LevelError) { | ||
| if globalLogger.Enabled(globalCtx, slog.LevelWarn) { |
Contributor
There was a problem hiding this comment.
why also change LevelError to LevelWarn?
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
A worker script that dies after boot (non-zero exit status) currently logs the same debug-level
"restarting"message as a cleanFRANKENPHP_LOOP_MAXrecycle — same level, same message text. At the default log level a crash is therefore invisible to operators:exit_status, the one datum needed to triage the death, is only obtainable by running the whole server at debug level.We hit this in production (Shopware on FrankenPHP 1.12.4, worker mode):
frankenphp_worker_crasheswas steadily incrementing at ~0.03% of requests, each crash converting one user request into an empty 500, with zero trace in any log — app log, stderr, or FrankenPHP's own output. It took us three debugging sessions to find the Prometheus counter, and we still could not see the exit statuses.This is a regression
Up to v1.2.x the crash path was clearly distinguished (worker.go @ v1.2.5):
That error-level line is, for instance, how the reporter of #774 noticed their problem at all. Somewhere in the worker-thread refactoring both paths converged on debug-level
"restarting".What this PR does
tearDownWorkerScript(non-zero exit after boot,StopReasonCrash) now logs at warn with the historical, distinct message"unexpected termination, restarting", keeping theworker/thread/exit_statusattributes. Warn matches the neighboring worker-failure logs in the same function; happy to bump it to error (the 1.2.x level) if preferred.LOOP_MAXrecycling) stay at debug — they are frequent and healthy, raising them would be noise.Enabled()checkedLevelErrorwhileLogAttrswroteLevelWarn.testdata/crashing-worker.php(boots fine,exit(1)on its second request — the exact scenario of the code comment) and a test asserting the warn-level line withexit_status=1is emitted.No behavior change beyond logging.
Fixes Worker crashes are logged at debug level only: invisible in production, in-flight request becomes an empty 500 #2601